Using the thread ID from logging is a good idea.

Regarding the necessity: in some cases definitely yes. But only if there is a problem with threading itself. Its probably not required for finding bugged configuration files or DocBook XML.

We can probably close this PR?

Why do you think we should close it? I still think it is indeed rather useful to have thread IDs in messages.

My initial criticism (which I kept to myself because I suck) of this PR was just that it was never clear when the main thread did stuff, so I would add annotations for that as well. I had started on a commit to that end which I have now pushed here: 1dfbb46 (not editing your branch; not finished but you should get the idea).

I don't think I have quite understood Tom's comment -- in any case, however you do it is fine with me, as long as we have the proper associations between thread name + message on the command line (and potentially in a log file).

Finally, I am really sorry for the lack of answers from me here.

@sknorr

[...]
I don't think I have quite understood Tom's comment -- in any case, however you do it is fine with me, as long as we have the proper associations between thread name + message on the command line (and potentially in a log file).

That's what my initial comment was aiming for: to preserve a unique thread name for logging output. To make each threads distinguishable, you need these two steps:

1. Pass a name when you call the Thread(name='some unique name', ...) class. Probably you need to add this in file docserv.py, line 338 and 343 (master).
2. Insert the thread name placeholder (%(threadName)s) into your log formatter docserv.py (line 296).

Whenever you call log.debug() or any of the other functions, you should see the unique name in the logger output. Here is a small example:

import logging
import threading

format = "%(asctime)s [%(threadName)s]: %(message)s"
logging.basicConfig(
    format=format,
    level=logging.DEBUG,
)


def worker():
    """thread worker function"""
    logging.debug('doing some work')


threads = []
for i in range(5):
    t = threading.Thread(target=worker, name="MyThread-%s" % i)
    threads.append(t)
    t.start()

gives the following output:

2019-04-25 21:07:00,531 [MyThread-0]: doing some work
2019-04-25 21:07:00,532 [MyThread-1]: doing some work
2019-04-25 21:07:00,532 [MyThread-2]: doing some work
2019-04-25 21:07:00,532 [MyThread-3]: doing some work
2019-04-25 21:07:00,532 [MyThread-4]: doing some work

Hope that clarifies it.

Oh, one additional comment from me.

Looking at Stefan's commit 1dfbb46, I think it isn't necessary to pass the thread name for each and every .debug() call.

I haven't tried it yet, but if you apply the two steps from my last comment, the output will be changed accordingly, containing a unique thread name. Makes the code a little bit easier to read and maintain I suppose.